AWS ParallelCluster ジョブサブミットからコンピュートが起動しジョブが処理開始されるまでの時間計測方法

大村保貴

2022.06.03

この記事は公開されてから1年以上経過しています。情報が古い可能性がありますので、ご注意ください。

AWS ParallelCluster でジョブをサブミットしてからコンピュートノードが起動し処理を開始するまでの時間を確認したいです。ストップウォッチで測る以外に良い方法はないでしょうか？

ありますよ！ヘッドノードのログを見ればいいんです！！

計測方法早見

ヘッドノードの /var/log/slurmctld.log ログを確認します。

対象	メッセージ
ジョブのサブミット日時	`_slurm_rpc_submit_batch_job: JobId=[Number]`
ジョブの処理開始日時	`Resetting JobId=[Number] start time for node power up`

[2022-06-03T03:33:06.381] _slurm_rpc_submit_batch_job: JobId=4 InitPrio=4294901759 usec=1093
[2022-06-03T03:33:06.593] sched: Allocate JobId=4 NodeList=large-dy-large-1 #CPUs=1 Partition=large
[2022-06-03T03:38:35.349] Node large-dy-large-1 now responding
[2022-06-03T03:38:42.965] job_time_limit: Configuration for JobId=4 complete
[2022-06-03T03:38:42.965] Resetting JobId=4 start time for node power up
[2022-06-03T03:38:43.329] _job_complete: JobId=4 WEXITSTATUS 0
[2022-06-03T03:38:43.329] _job_complete: JobId=4 done

sudo less /var/log/slurmctld.log

# ジョブIDで検索すると該当のログをすぐ見つけられます
/JobId=[Number]

検証環境

項目	値
ParallelCluster	3.1.4
OS	CentOS 7
CPU	Intel
HeadNode	t3.micro
ComputeNode	c6i.large

計測してみた

ヘッドノードからジョブをサブミットします。test.shはホスト名を返すだけのシェルスクリプトです。

$ sbatch -p large -N1 test.sh

キューの様子を見守る

squeueコマンドを連打してキューからジョブがなくなるまで見守りました。結果はジョブをサブミットしてから5分36秒経過後にジョブが処理開始されました。原始的な方法ですが一応確認できますね。

[centos@ip-10-0-1-170 ~]$ squeue
             JOBID PARTITION     NAME     USER ST       TIME  NODES NODELIST(REASON)
                 4     large  test.sh   centos CF       5:36      1 large-dy-large-1
[centos@ip-10-0-1-170 ~]$ squeue
             JOBID PARTITION     NAME     USER ST       TIME  NODES NODELIST(REASON)
                 4     large  test.sh   centos  R       0:01      1 large-dy-large-1
[centos@ip-10-0-1-170 ~]$ squeue
             JOBID PARTITION     NAME     USER ST       TIME  NODES NODELIST(REASON)

ログ確認

ヘッドノードの /var/log/slurmctld.log ログを確認します。ジョブをサブミットした時刻と、処理を開始時刻が記録されています。

対象	メッセージ
ジョブのサブミット日時	`_slurm_rpc_submit_batch_job: JobId=[Number]`
ジョブの処理開始日時	`Resetting JobId=[Number] start time for node power up`

ログを検索するときはジョブID（JobId=）で探すと早いです。

[2022-06-03T03:33:06.381] _slurm_rpc_submit_batch_job: JobId=4 InitPrio=4294901759 usec=1093
[2022-06-03T03:33:06.593] sched: Allocate JobId=4 NodeList=large-dy-large-1 #CPUs=1 Partition=large
[2022-06-03T03:38:35.349] Node large-dy-large-1 now responding
[2022-06-03T03:38:42.965] job_time_limit: Configuration for JobId=4 complete
[2022-06-03T03:38:42.965] Resetting JobId=4 start time for node power up
[2022-06-03T03:38:43.329] _job_complete: JobId=4 WEXITSTATUS 0
[2022-06-03T03:38:43.329] _job_complete: JobId=4 done

経過時間を計算してみると5分36秒です。原始的な確認方法と同じタイムですね。

>>> from datetime import datetime
>>>
>>> submit_job = datetime.fromisoformat('2022-06-03T03:33:06.381')
>>> start_job = datetime.fromisoformat('2022-06-03T03:38:42.965')
>>> print(start_job -submit_job)
0:05:36.584000

ジョブのサブミットから処理開始までの時間をログから確認できました。

まとめ

ヘッドノードの /var/log/slurmctld.log にジョブのサブミット・処理開始日時が記録されている。

おわりに

postinstall でのインストール処理に時間かかり、コンピュートノード起動までが遅い気がするときは postinstall 設定あり、なしのパーテイションを用意してコンピュートノード起動までの時間を比較してみてください。とくにカスタム AMI 化を検討しているのでしたら一度ご確認いただくとよろしいかと思います。